Skip to content

fix(cli): with the stdio MCP transport on, a host plugin's console output while serving a call reaches stderr - #33159

Merged
objectstack-fleet[bot] merged 4 commits into
mainfrom
claude/project-thread-tfbq5b
Nov 13, 2026
Merged

objectstack-fleet[bot] merged 4 commits into
mainfrom
claude/project-thread-tfbq5b

Conversation

@objectstack-fleet

Copy link
Copy Markdown
Contributor

Requested by Tesla · project thread

Fixes #32942

Clause-②: no
Metadata-protocol: none

维护者速读

  • 改了什么:stdio MCP 模式下,宿主插件在处理工具调用时写的 console.log / console.info / console.debug / process.stdout.write 现在都会出现在 stderr;stdout 仍然只有 JSON-RPC 帧。
  • 为什么改:MCP 客户端一启动就发 initialize,收到答复立刻发 tools/call,这些调用在 serve 的“启动静默窗口”还没关闭时就被处理了,窗口把它们的日志当成启动噪音直接丢掉,两个流都看不到(拦截器审计日志因此在 stdio 部署上全部丢失)。
  • 风险与回滚:小。只在 stdio 传输接管 stdout 之后才放行;HTTP 启动完全不变(有对照用例)。代价:stdio 启动时,传输接管之后、横幅之前的启动杂讯(本夹具上 23 行 [Registry])也会直接打到 stderr。回滚 = revert 本 PR,不涉及数据。
  • 先看:packages/cli/src/commands/serve.ts 的 quietHolds 与 isProtocolStdoutClaimed;packages/mcp/src/protocol-stdout.ts 的 PROTOCOL_STDOUT_CLAIM 标记;packages/cli/test/serve-stdio-stdout-purity.e2e.test.ts 新增的 #32942 一组。
  • 两分钟验证:OS_TEST_TIERS=nightly pnpm --filter @objectstack/cli exec vitest run test/serve-stdio-stdout-purity.e2e.test.ts(先 build cli),预期 3/3 通过。
  • 需要你做的:无,席位落地。

What changes

The mechanism, measured at origin/main (b22be279). It is not the stdout redirect and not the transport's stdout claim. It is serve's boot-quiet window. A stdio client writes initialize at spawn and its first tools/call as soon as that is answered. The transport attaches inside runtime.start(), and the window closes about 100 ms after runtime.start() returns. So the first calls are served while the window is still open. During the window console.log and console.debug are replaced by no-ops, and process.stdout.write is filtered down to kernel-logger records for the post-banner replay. A host interceptor's line is not one of those records, so it was dropped and reached neither stream. console.warn and console.error go to stderr directly and were never affected, which is why the card saw the MCP WARN but not the interceptor line.

  • @objectstack/mcp, protocol-stdout.ts: protocolStdout() now sets a mark on process.stdout (PROTOCOL_STDOUT_CLAIM, a Symbol.for key) when the stdio transport claims the stream. The mark is set before connect() attaches stdin, so no call can be served before it exists. mcp-server-runtime.ts is not edited.
  • @objectstack/cli, serve.ts: the window's stdout and console wrappers ask quietHolds() (the window is open AND stdout is not claimed) per write, instead of bootQuiet. From the claim on, bytes go to origStdoutWrite, which is the stderr forwarder redirectStdoutToStderr() installed, never to the real stdout. isProtocolStdoutClaimed() reads the mark by key so serve does not import the MCP package to ask.
  • Unchanged: the redirect itself; the window before the claim (every plugin's init() and the starts ahead of the MCP plugin are still held back under stdio); the whole window on a boot without the stdio transport; printDiagnostic (serve's own lines) stays suppressed while bootQuiet is set.

Each channel after the fix, under stdio, from a call served inside the window (all measured by the pin): console.log, console.info, console.debug and process.stdout.write reach stderr through the forwarder; console.warn and console.error reach stderr as before. None reaches stdout. From a timer after the banner every channel already reached stderr at main, and still does.

Tests

  • packages/mcp/src/protocol-stdout.test.ts (+1): protocolStdout() sets the mark on process.stdout under Symbol.for('@objectstack/mcp:protocol-stdout-claimed'), and the mark is absent before the call.
  • packages/cli/test/serve-stdio-stdout-purity.e2e.test.ts, the existing child-process harness for this seam (built bin/run.js, a real minted osk_ key), new top-level describe with two cases. The shared beforeAll / afterAll moved from inside the os serve writes its banner and kernel logs to the stdout the stdio MCP transport owns #7915 describe to file level, unchanged, so both describes use one minting boot. The fixture config gains a host plugin whose tool-call interceptor writes through all six channels. With FX_HOLD_FOR_CALL=1 it holds kernel:ready until a call is served (cap 30 s), so the call lands inside the window deterministically instead of racing it. The os serve writes its banner and kernel logs to the stdout the stdio MCP transport owns #7915 case makes no tool call, so the plugin is inert there.
    • stdio: initialize at spawn, tools/call list_objects the moment its answer is read. Every channel's [fx-call] CHANNEL stdio:list_objects line is on stderr AND before Server is ready. Every stdout line parses as a JSON-RPC frame. [fx-boot-chatter] from init() is on neither stream.
    • CONTROL, HTTP: the same plugin over POST /api/v1/mcp after boot: every channel's line on stderr, stdout empty, [fx-boot-chatter] still held back.
    • Both run at OS_LOG_LEVEL=warn. The os serve writes its banner and kernel logs to the stdout the stdio MCP transport owns #7915 case runs at info, a verbose level at which serve never opens the window, so the defect cannot be reached there.

Acceptance notes

  • Ruling grep (ruling|Ruling-ref|maintainer|⛔) on the touched surface: serve.ts has 65 hits, none in the redirect or window region (L2160 to L2850 before the edit, the closest are L2158 "never a second copy", L2328, L2342, L2387 on the port flags). protocol-stdout.ts and its test have 0. The e2e file has 3, all in the existing os serve writes its banner and kernel logs to the stdout the stdio MCP transport owns #7915 harness text. mcp-server-runtime.ts (13 hits) is not edited.
  • Cost under stdio, stated because it is real: whatever the boot writes to the console after the transport claims stdout is no longer held back. On this fixture that is 23 [Registry] console.log lines and one WARN that now print on stderr before the banner instead of being dropped (the WARN was replayed under the banner before). The stream cannot tell a call's line from the rest of the boot. Holding them would mean marking request context in the MCP runtime's dispatch, outside this card's surface. Nothing reaches stdout either way.
  • The pin lives in a .e2e file, so it runs on the nightly tier, the same tier as the os serve writes its banner and kernel logs to the stdout the stdio MCP transport owns #7915 purity pin it sits beside. The file is now about 19 s of local wall (four boots) and declares no test-budget line, as before this PR. Flagged for the seat: whether it needs one now.
  • HTTP requests served before the window closes would lose their console lines the same way, but an HTTP client does not normally reach a server before its banner, and the card's HTTP control prints the line. Left as is; no change on the HTTP path.
  • The card reproduced through os start; start spawns serve with inherited stdio, so the fix is in serve. Both doors were measured before and after.

Verification

Readings at head f4bbd648 (fix commits on b22be279; origin/main merged once before opening, no overlap with this diff).

Measured at origin/main first (the premise holds, with a sharper mechanism)

A scratch app with the card's interceptor plugin plus a timer that writes through every channel 4 to 8 s after boot, a minted key, OS_MCP_STDIO_ENABLED=true:

  • Calls written after the banner (my first harness): the [qa-interceptor] line and every timer line on stderr, under both os serve --dev and os start --no-ui. Not reproduced.
  • Calls written the way an SDK client writes them (initialize at spawn, tools/call on its answer, before the banner): os serve and os start both answered list_objects and denied delete_record (PERMISSION_DENIED from the interceptor), stdout carried 3 frames and nothing else, and the interceptor's console.log line was on NEITHER stream. A process.stderr.write line from the same interceptor was on stderr. Reproduced on both doors.
  • Never observed: a non-frame line on stdout. The defect loses lines; it does not corrupt the protocol stream.

After the fix, same harness: the [qa-interceptor] lines on stderr on both doors, stdout 3 frames only.

Package tests, typecheck, lint, derived gates
  • pnpm --filter @objectstack/mcp test: Test Files 64 passed (64), Tests 1138 passed (1138)
  • pnpm --filter @objectstack/mcp typecheck, pnpm --filter @objectstack/cli typecheck: exit 0
  • pnpm --filter @objectstack/cli exec vitest run --project unit --maxWorkers=2: Test Files 416 passed (416), Tests 5934 passed (5934)
  • OS_TEST_TIERS=nightly … vitest run test/serve-stdio-stdout-purity.e2e.test.ts: Tests 3 passed (3)
  • pnpm lint: exit 0
  • node scripts/pm/dispatch-gates.mjs --commands: 72 families derived; 70 exit 0, 2 NOT MEASURED (exit 3, PREREQUISITE NOT MET: check:dual-build-cjs-loads needs dist/ for packages outside this closure, check:i18n-coverage a partial lint round). check-plugin-teardown-shape --self-test first exited 3 on the shallow clone, and passed (48 cases) after fetching its pinned fixture commit. --ran reconciliation: 72 derived, 70 run, 2 NOT-MEASURED, 0 UNRUN.
  • The integration tier of packages/cli is declared to CI.
Ablations (both red, both restored)

The e2e spawns the built CLI, which loads both packages from dist/, so each leg was rebuilt and checked with scripts/ablation-dist-preflight.mjs.

  • serve ignores the claim: scripts/ablation-replace.mjs on serve.ts, anchor const quietHolds = () => bootQuiet && !isProtocolStdoutClaimed(); (x1 to x0) replaced by const quietHolds = () => bootQuiet;. Rebuilt; preflight: marker absent from all 952 built files. Result: 1 failed, 2 passed: the stdio case, the console.log line of the stdio call is missing from stderr; the os serve writes its banner and kernel logs to the stdout the stdio MCP transport owns #7915 case and the HTTP CONTROL stayed green. Restored: blob == HEAD (5d4e3372), git diff HEAD empty, rebuilt, preflight marker present.
  • the mark removed: the one line that sets PROTOCOL_STDOUT_CLAIM to true on the stream deleted (x1 to x0). mcp unit: 1 failed, 2 passed (the new mark case). mcp rebuilt, preflight absent from all 12 built files; e2e: 1 failed, 2 passed, the stdio case with the same message, which pins the key both packages spell. Restored: blob == HEAD (5cc99b80), git diff HEAD empty, rebuilt, preflight marker present in dist/index.js and dist/index.cjs.

Generated by Claude Code

…rt claims stdout

A stdio MCP client writes initialize at spawn and its first tools/call as
soon as that is answered, so the calls are served inside serve's boot-quiet
window. Whatever a host plugin wrote to the console from them was dropped
as boot chatter and reached neither stream. protocolStdout() now marks
process.stdout when the transport claims it, and the window stops holding
back console and stdout bytes from that moment; they go to the stderr
forwarder, never to stdout. An HTTP-only boot never claims, so its window
is unchanged.

Co-Authored-By: Claude <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01L9qibwitFuZejYP8o8ZdXC
Co-Authored-By: Claude <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01L9qibwitFuZejYP8o8ZdXC
@github-actions github-actions Bot added size/m documentation Improvements or additions to documentation tests tooling Fix lands in tooling, not a product package — enters pm:queue only with Unblocks: or a named surface labels Nov 13, 2026
@github-actions

Copy link
Copy Markdown
Contributor

📓 Docs Drift Check

3 anchor(s) derived from 2 changed package(s); no hand-written page names any of them, so this run has nothing to list — not a clean bill of health. This check sees only pages that NAME a derived anchor: one that documents this change in prose, or enumerates it in an authoring dialect, names none and stays invisible to it on every run.

What this run could not see
  • 1 anchor(s) matched too much of the corpus to be a work list: os serve (command, 50 pages)
  • 1 name(s) were too generic to anchor anything (single lowercase words)
  • the SDK route bridge reached 65 of 247 client-bound route-ledger rows — the other 182 have no registrar path: tail to select them, so pages documenting THEIR client methods cannot appear above, on this or any run. Of those 182: 0 are remediable by widening that discovery convention (an in-repo file declares the path; the convention did not scan it); 59 are structural — on a ledger where NOT ONE row is declared in-repo, so no discovery change reaches them at any price; 123 are undecided (no in-repo declaration, on a ledger that has other in-repo registrars — absence and an unreadable spelling are not distinguishable here). The rows themselves: node scripts/docs-audit/affected-docs.mjs --bridge-coverage
  • a page that states a rule by its inputs shares no identifier with the emitter that implements the rule, so an emitter-only diff cannot list it — not on this run and not on any run. Measured on fix(driver-sql): emit varchar(maxLength) for a text field a declared index keys on #11430: content/docs/protocol/objectql/types.mdx documents the text-family column mapping by the ObjectQL type names it maps FROM (text / textarea / html) while the diff changed createColumn; it went unlisted, and it was the page that diff falsified, in four places. No shared token exists to detect this on, so a rule your change carries has to be re-read by hand in the pages that restate it.
  • a key NAME is not a key, so the hand re-read the line above prescribes can land on the wrong schema. The same spelling is authorable on one governed type and a [REMOVED] tombstone on another for each of active, aria, joins, objects, template, tools and version (censused on [finding] tools is a key on BOTH AgentSchema (tombstoned, dead) and SkillSchema (live, cloud-attested), so a name-based search attributes skill examples to the agent key — it produced a false stop-the-line alarm on PR #19059 #19093 over the liveness ledger's governed types, top-level keys); nothing in a search result distinguishes the two, so a grep hit on a LIVE example reads as evidence about the DEAD key. Measured on fix(spec): the agent.tools liveness row says dead — it claimed live on a key the schema tombstoned #19059: content/docs/ai/agents.mdx was reported as contradicting the agent.tools tombstone over its tools: example at :161, which is inside the defineSkill({ block opened at :155 — the page was already correct. Settle ownership by PARSING the value against both schemas, never by the name: that literal PASSES SkillSchema, and as an AgentSchema it FAILS at tools with the tombstone prescription. ⛔ These names are not the whole class — a key retired through a .strict() guidance map leaves no tombstone in the walked shape and none of them here (tool.category, live as AIToolDefinition.category).

Coarse fallback — 47 page(s) merely mention a changed package (the pre-#9192 predicate, kept for the deliberately-wide backstop): node scripts/docs-audit/affected-docs.mjs --json 47f6c939f132df9185e1259740e2cbe4156802e1 → packageMentionDocs.

Which tree this was computed on

This run read content/docs from 1c1ccf13605314eef7ce0c46f48e6e2c62a25f3c — the merge of head f4bbd64872cd5597a69d84b7e5b3c2f0ca063248 into base 47f6c939f132df9185e1259740e2cbe4156802e1, which is what actions/checkout gives a pull_request run. Not the PR head.

A worktree cut from an older main holds a different content/docs, so re-deriving there can legitimately return a different list — that is a different tree, not a wrong row. To answer on the same tree:

# while this PR is open — GitHub drops the merge commit once it closes
git fetch origin 1c1ccf13605314eef7ce0c46f48e6e2c62a25f3c && git checkout 1c1ccf13605314eef7ce0c46f48e6e2c62a25f3c
# afterwards, rebuild it from the two parents, which stay fetchable
git fetch origin 47f6c939f132df9185e1259740e2cbe4156802e1 f4bbd64872cd5597a69d84b7e5b3c2f0ca063248 && git checkout -B drift-repro 47f6c939f132df9185e1259740e2cbe4156802e1 && git merge --no-ff f4bbd64872cd5597a69d84b7e5b3c2f0ca063248

node scripts/docs-audit/affected-docs.mjs --json 47f6c939f132df9185e1259740e2cbe4156802e1

⚠️ That checkout carried uncommitted changes, so the commit above does not fully identify what was read.

@objectstack-fleet

Copy link
Copy Markdown
Contributor Author

domain:server#7 · os-tesla · session_01L9qibzuZJBQY4wUQFJbkfx

维护者速读 · PR #33159 @ f4bbd648 · 2026-11-13T22:52Z

  • 改了什么:stdio MCP 模式下,宿主插件在处理工具调用时写的 console.log / info / debug 和 process.stdout.write 现在都进 stderr。stdout 仍然只有 JSON-RPC 帧。
  • 为什么改:客户端一启动就发 initialize,收到答复立刻发 tools/call。这些调用在 serve 的启动静默窗口里就被处理了,窗口把它们的输出当启动噪音丢掉,两个流都看不到(os start with the stdio MCP transport drops a host plugin console.log written after boot: it reaches neither stdout nor stderr #32942)。
  • 权限与边界:只在 stdio 传输接管 stdout(打上 Symbol.for 标记)之后放行,而且放行的去处是已有的 stderr 转发器,不是真正的 stdout。HTTP 启动完全不变,有对照用例。
  • 风险与回滚:代价是 stdio 启动时,接管之后、横幅之前的启动杂讯也直接打到 stderr(本夹具上是 23 行 [Registry])。席位接受:诊断输出本来就该在 stderr,这与 os serve writes its banner and kernel logs to the stdout the stdio MCP transport owns #7915 的输出策略一致。回滚就是 revert。
  • 先看:serve.ts 的 quietHolds;protocol-stdout.ts 的 PROTOCOL_STDOUT_CLAIM。
  • 需要你做的:无,席位落地。
  • 席位意见:落地。Clause-② no,所以由席位自己通读,结论 PASS。两个反证(ablation)都会变红,没有碰受管面,改动 451 行。

席位核对

  • 形态: draft → main,正文写 Fixes #32942,合并后应当关卡;正文其余地方没有挨着别的 open 卡号的闭合关键词。
    • Clause-②: no、Metadata-protocol: none,patch changeset(cli、mcp)。
    • 文件面 = 认领 6865258677:serve.ts、protocol-stdout.ts 及其测试、changeset。mcp-server-runtime.ts 没有改动。
  • 前提实测: dev 在 b22be279 上复现了问题,用的是 SDK 客户端的时序。机制是启动静默窗口:console.log / debug 被换成空操作,stdout.write 只留下 logger 记录。stdout 从未出现过非帧行(报告 6866783001)。
  • 门禁:
    • 本地在 f4bbd648 上:mcp 1138/1138,cli unit 5934/5934,typecheck 和 lint 都 exit 0。
    • 推导出 72 个门禁族,全部 exit 0,0 个 NOT MEASURED。正文写的「70/72,2 个 NOT MEASURED」已过时:完整 pnpm build 之后,check:dual-build-cjs-loads exit 0(123 个 require 入口、2605 个 CJS 文件),check:i18n-coverage exit 0(没有新的未翻译串)。
    • CI check-runs 在 ACCEPT 时:27 success、16 skipped、0 失败,Test Core 1–8/8 仍在跑。自动合并会等必需检查。
  • 契约复审(席位通读):
    • 接管之后,console 走 origStdoutWrite。它是 redirectStdoutToStderr() 装上的 stderr 转发器,所以 stdout 不可能出现非帧行。
    • 每次写入都重新判断标记,因为接管发生在窗口之内。
    • 标记在 connect() 接上 stdin 之前打上,所以不存在「已在服务但还没标记」的空隙。
    • HTTP 启动从不接管 stdout,窗口与以前相同。
    • 三个 pin:stdio 下六个通道都在横幅前出现在 stderr;stdout 每行都能解析为帧;HTTP 对照。
    • 两个 ablation 都变红,并且都恢复到 HEAD:一是 serve 忽略标记,二是 mcp 不打标记。
  • 接受的偏差:
    • 上面所说的 stdio 启动杂讯改到 stderr。
    • nit:新加的 JSDoc 块插在 getAvailablePort 的文档注释和类之间,那段注释因此和另一段文档注释叠在一起。留待下次有理由推送时再挪,不为它单独推送。
    • e2e 文件本来就存在,按 .e2e 名字分层,也已经在 check-cli-test-child-env 名单里,不需要预算行(本地约 19 s)。
  • 范围外去向: 无。
  • 落地条款: 维护者常设落地令 「按 pm-dispatch 审过的pr你可以自主落地」 (2026-10-30T14:20Z)。

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

documentation Improvements or additions to documentation size/m tests tooling Fix lands in tooling, not a product package — enters pm:queue only with Unblocks: or a named surface

Projects

None yet

Development

Successfully merging this pull request may close these issues.

os start with the stdio MCP transport drops a host plugin console.log written after boot: it reaches neither stdout nor stderr

2 participants